一次核心系统的告警分析过程——数据库问题智能分析实践 | 运维进阶
【摘要】本文详述了一次通过数据库智能运维平台进行的数据库性能问题分析过程，不需要登陆操作系统获取其他信息，减少人为误操作的风险，并找到了真正的根源。关于数据库自能运维平台的建设，也可参考文章《定位分析从几小时变成一分钟--银行数据库智能运维平台建设经验分享 | 最佳实践》（点击标题即可），有助于进一步理解本文。
【作者】孔再华，IBM认证高级DBA，SAP认证BASIS，具有丰富的数据库环境问题诊断和性能调优的经验。在数据库同城双活，集群，多分区，分布式等项目实施上具有丰富的经验。现任职于中国民生银行科技部，工作致力于数据库同城双活架构建设，数据库分布式架构建设和数据库智能运维（AIOps）方向。对于如何将AI技术运用在运维领域具有浓厚的兴趣和创新热情。
数据库智能运维
一开始想做数据库智能运维的时候其实并不知道最终会做成什么样子，包括现在也是，不知道会实现多大价值。当时一方面相信人工智能的算法能力，一方面也清楚仅仅是在数据库这个领域，大量的性能数据都非常有挖掘价值，但是没有利用上。同时联想到在平时的数据库运维中遇到的痛点，智能运维应该会有很大帮助。所以还是下决心将工作开展起来。
当前数据库智能运维系统先实现了一个小目标：Db2 数据库的问题实时检测和智能分析。首先是将数据库级别的性能指标都监控起来。Db2 数据库级别就有 400+ 指标，我甚至都不了解这些指标的具体含义。人为去定义指标的价值也不是正确的做法，所以不如全部监管起来。每个系统的每个指标都基于机器学习在历史数据上计算出异常模型，然后对实时指标数据检测打标识。这样就做好了数据库指标的异常检测功能。
然后为了展现这些异常，我们基于人为的产品知识定义，结合历史数据的相关性分析，最终形成了数据库指标的知识图谱。这样当很多异常指标发生的时候，我们能很快发现异常点聚合在一起时什么功能什么原因。
在此基础上，为了方便普通用户能够看懂这个专业工具，我们还将一些指标集合定义成问题场景。开发了一键智能分析功能，基于场景来解释当前系统的异常现象，并且下钻展示影响的 SQL 是什么。
最后查到的问题 SQL ，我们进一步开发了 SQL 的性能详情页面，展示 SQL 的指标发展趋势，执行时间分布等。这样能够很好的确定 SQL 是不是有问题，该从哪里着手来解决问题。
一次核心系统的告警分析过程
2019 年 10 月 31 日， 17 ：08 ：54 ，核心系统数据库活动会话数高，达到 120 多个。活动会话数是数据库堵塞的一个重要特征指标。如果分析不出来原因，很可能下一次就会导致数据库全局堵塞，严重影响业务。尤其是核心系统出现这样的问题，需要格外重视。
如果是以前活动会话高并且很快消失，当时以及事后 DBA 其实都很难分析出原因是什么。即便监控当时抓取到了正在执行的 SQL ，也没有足够的数据来着手分析。可能最好的办法是问题发生的时候抓取 stack 甚至是 trace ，明显这也是不可能的，风险太大。
从智能运维平台能发现什么？
那么智能运维平台能不能帮我们来分析定位问题根源呢？在平台里找到这台机器，查看问题发生的时间点。
图 1. 异常指标展示图
在数据库智能运维平台，观察到当时的时间点一共有 4 个数据库指标发生了异常：TOTAL_SECTION_SORT_PROC_TIME ， TOTAL_SECTION_SORT_TIME ， POOL_WRITE_TIME ， POOL_ASYNC_WRITE_TIME 。
是排序问题吗？
首先看排序异常的原因是什么。从产品里面能看到与排序异常相关的贡献最高的 sql 是一条查询语句 :
图 2. 排序 SQL 排行
进一步点击这个语句，查看 sql 的历史执行指标分布， sql 当前的执行时间分布图。
图 3. SQL 详情分析图
从指标的分布来看，这条 SQL 没有出现指标的特别异常情况。这条 sql 当时平均执行时间只有 1.72 毫秒，其中 POOL_READ_TIME 占 91.87% ， TOTAL_SECTION_SORT_PROC_TIME 占 2.16% 。因此这条 sql 看起来并不是我们需要怀疑的对象。
是数据写问题吗？
下面再看一下和 POOL_WRITE_TIME 相关的 sql 贡献度。从指标的时间趋势图来看，当时这个指标确实出现了很大的变化，并且超出了智能运维平台计算出来的动态阈值。同时在 SQL 排行能看到很多 SQL 都有比较高的贡献度。
图 4. 数据写指标排行
点击排行第一的 sql ，是条 insert 语句。这条语句很明显在这个时间段出现了异常。
图 5. SQL 详情
首先是 sql 的 POOL_WRITE_TIME 这个指标历史上消耗时间是 0 ，现在突然有个很高的剑锋。其次是这条 sql 在当前的执行时间也比平时高很多，基本上可以确认当前遇到了瓶颈。
是 latch 等待问题吗？
然后当我们进一步分析这条 SQL 的执行时间发现，当前执行时间主要消耗在 TOTAL_EXTENDED_LATCH_WAIT_TIME 上面， POOL_WRITE_TIME 占 3.74% 。从经验来说，我们以前碰到过热表的插入堵塞在 latch 的等待上这样的问题。看起来这又是一个 latch 堵塞导致的 sql 执行慢，短时间内并发变高，从而导致数据库出现当前会话高这样的告警。后面 latch 解锁后就恢复正常了。
如果基于 TOTAL_EXTENDED_LATCH_WAIT_TIME 来查看当前的堵塞 sql 会发现，同一时间段有很多 SQL 都发生了 latch 等待事件。
图 6. Latch 等待排行
Latch 等待时间排行前四的 SQL 都是插入语句，并且都是热表。语句的等待时间占比都很高。我们再从数据库 paas 平台查看当时的 latch 是什么。很显然当时的 SQLO_LT_SQLB_BPD__bpdLatch_SX 这个 latch 等待时间出现了一个波峰异常。基本和 SQL 的特征对应上了。
图 7. Latch 详情
看起来我们要在 latch 的分析上越走越远。所有的迹象证明，当时的 SQL 堵塞都是因为 latch 等待导致的。而这个 bpdlatch 也是我们的老朋友了，如果处理不好的话，后面可能成为我们的大麻烦。这个 latch 其实加载在内存里数据页面上的，如果有频繁访问的热点页面，这个 latch 就可能会导致堵塞。热点表的数据页和索引页都可能导致这样的问题。在以往的经验值我们会想办法将热点数据和热点索引想办法打散，通过表分区， Random 索引等方式来进行调优，减少 latch 竞争的概率。
数据同步写才是根源
但是智能运维平台一开始向我们展示的并不是 latch 问题。这个系统里的 latch 问题也不是第一次了。这些热点表为什么会在同一时间都发生了 latch 等待的问题呢？还有为什么 POOL_WRITE_TIME 会出现在 insert 语句的执行时间消耗里？数据库有一个常识，那就是数据的写是异步的。数据库事务会先写日志，然后才能提交成功。内存里的脏数据是异步写的，不会出现在 sql 的执行时间里面。这是为什么这些 insert 在此之前是没有 POOL_WRITE_TIME 的时间消耗的。因此即便当前 sql 的 POOL_WRITE_TIME 占比只有百分之几，但是已经是很不寻常的现象了。如果 SQL 在等待写数据，那么它所占有的 latch 时间也会变长，其他 sql 等待这个 latch 的时间也会变长，造成堵塞。所以最终看来， sql 是被 latch 所堵塞。但是源头很可能是 POOL_WRITE_TIME 导致的。智能运维平台所暴露的这个 POOL_WRITE_TIME 问题才是真正的关键，不能被忽略。SQL 只有在同步写的情况下才会出现等待 POOL_WRITE_TIME 。
Db2 数据库写数据机制
那么如何确定数据库发生了同步写的行为呢？又该怎么去解决这个问题？那么我们要先了解下 DB2 数据库的写数据行为是如何控制的。DB2 的写数据行为有三种触发条件，在 10.5 版本以前控制数据写的行为由 softmax 和 chngpgs_thresh 两个数据库参数来控制。
Softmax ：这是一个控制检查点发生次数的参数。数值是单个日志大小的百分比。如果事务占用日志超过 softmax 多制定的日志量，检查点就会发生，缓冲池的脏数据会被刷到磁盘。这个参数能够保证数据库在崩溃恢复的时间。本系统设置成了 520 ，也就是 5.2 个日志大小的量。如果因为这个阈值达到发生写数据行为， pool_lsn_gap_clns 这个数据库性能指标会记载发生的次数。
图 8. Softmax
Chngpgs_thresh ：这个参数设置了在缓冲池里脏数据的百分比阈值，如果达到这个阈值，异步页面清理线程会启动起来。在我们这个系统里面， chngpgs_thresh 被设置成了 80 。也就是缓冲池脏数据超过 80% 会开始异步刷脏数据。这个行为是可以被监控到的。pool_drty_pg_thrsh_clns 就是因为这个阈值达到而发生的次数。
图 9. Chngpgs_thresh
上述两个参数描述了数据库主动写数据的两种行为。然而最差的是第三种，因为缓冲池没有足够的空闲页面，新的 SQL 请求页面只能将缓冲池的脏数据先同步写入到磁盘，腾出空间才能继续进行。这种行为也是被数据库记录的。pool_drty_pg_steal_clns 性能指标就是出现这种行为的次数。那么我们来看看当时是不是出现了这种现象：
图 10. pool_drty_pg_steal_clns
很不幸，我们的系统当时出现了这一现象的高峰，也证明了之前数据库的活动会话高的根本原因是因为发生了数据的同步写，导致 SQL 整体变慢堵塞起来。这也是为什么在同一时间所有的热表都出现了整体缓慢的现象。
怎么解决问题？
解决这个问题的思路是从两方面着手，一是加快异步写的频率，减少同步写的概率。二是提高写数据的速度，减少同步写的时间。DB2 数据库中还有一个很重要的参数 num_iocleaners 。
num_iocleaners ：这个参数设置数据库启动的异步清理线程数。如果这个参数设置成 automatic ，那么数据库启动的时候会参照操作系统 CPU 的核数来自动定义。在我们的系统里这个数值是 40 ，可以考虑增大。
图 11. num_iocleaners
从 DB2 10.5 版本开始，数据库又新增了两个参数来替换之前的数据清理行为。page_age_trgt_mcr 和 page_age_trgt_gcr 分别用来设置脏数据在本地缓冲池和全局缓冲池的时间，超过这个设置的时间，数据库会将脏数据以 castout 的方式写到磁盘上。
图 12. page_age_trgt_mcr 和 page_age_trgt_gcr
如果要启用这两个参数， softmax 需要设置为 0 ，然后 DB2 的注册表变量 DB2_USE_ALTERNATE_PAGE_CLEANING 需要设置成 ON 。暂时我们的数据库都是从老版本升级上来，还没有使用到这种方式。
最终解决这个问题的方案是：调小 softmax 到 300 ，调小 chngpgs_thresh 到 50 ，持续监控 pool_drty_pg_steal_clns 的行为。
智能运维案例总结
本次数据库性能问题分析过程全部通过数据库智能运维平台来完成，不需要登陆操作系统获取其他信息，减少人为误操作的风险。
如果没有智能运维平台，我们可能在本次分析过程中最好的情况也只是分析到堵塞原因是 latch 引起的。然而真正的根源是发生了同步写现象。
我们从数据库智能运维平台第一时间获取到了准确的指标异常信息，并且根源追溯到影响的 SQL 。整个过程其实用时很少，对于第一时间需要处理异常的运维人员非常适合。分析时间短，问题定位准确，降低分析和处理的时间成本，不可用成本，减少未来发生更严重事件的风险。
本文原题：一次数据库问题智能分析实践；首发于公众号“民生运维” 觉得本文有用，请转发或点击“在看”，让更多同行看到
传统数据库系统如何实现智能化运维？
在线技术交流当前主流数据库运维模式还是基于“专家规则”的经验运维加上自动化运维的方法。然而面对越来越多的系统产生的海量运维数据，传统数据库运维遇到一些痛点，如运维场景覆盖面小；数据库运维产生的海量数据只有很少部分被管理起来，大量数据价值有待挖掘等。而通过建设机器学习问题分析平台，实现基于机器学习模型的异常检测 ， 根因定位和问题管理，是对“ 专家规则”模式的补充，可以解决海量数据运维痛点，提升现有运维能力。在本次活动中，我们邀请了本文作者孔再华老师，在线帮助大家解答在规划和实施数据库系统智能化运维的相关疑问。点击文末阅读原文，现在即可向专家提问 ↓↓↓
相关推荐：
下载 twt 社区客户端 APP
与更多同行在一起
高手随时解答你的疑难问题
轻松订阅各领域技术主题
浏览下载最新文章资料
长按识别二维码即可下载
或到应用商店搜索“twt”
*本公众号所发布内容仅代表作者观点，不代表社区立场